Remove redundant channel ID logging #4217

joostjager · 2025-11-11T12:52:28Z

This PR improves channel ID logging consistency and clarity.

Removes redundant channel ID text from log messages where the ID is
already included as a structured field. This reduces duplication and makes
it easier to filter logs by channel.
Updates the test logger to display the structured channel ID instead of
relying on message text. The logged ID is truncated for readability.
Also log peer id and payment hash as structured fields. Log message de-duplication is left for a follow up.

Together, these changes standardize how channel IDs appear in logs and make
them easier to parse and analyze.

Example output:

node 0 TRACE [lightning::ln::channel:5253]             p:0355f8 ch:ae3367 h:544e62 Building commitment transaction number 281474976710654 (really 1 xor 53018734980789) for channel ae3367da2c13bc1ceb86bf56418f62828f7ce9d6bfb15a46af5ba1f1ed8b124f for remote, generated by us with fee 253...
node 0 TRACE [lightning::ln::channel:5299]             p:0355f8 ch:ae3367 h:544e62    ...including outbound LocalAnnounced HTLC 0 (hash 544e62cee8033709e389e5b2755343d0d0fa8c4850215cfb6331717e80d1aea3) with value 10000
node 0 TRACE [lightning::sign::tx_builder:362]         p:0355f8 ch:ae3367 h:544e62    ...trimming outbound HTLC with value 10sat, hash 544e62cee8033709e389e5b2755343d0d0fa8c4850215cfb6331717e80d1aea3, due to dust limit 354
node 0 TRACE [lightning::sign::tx_builder:435]         p:0355f8 ch:ae3367 h:544e62    ...including to_local output with value 99796
node 0 TRACE [lightning::chain::chainmonitor:1407]     p:0355f8 ch:ae3367          Updating ChannelMonitor to id 1
node 0 INFO  [lightning::chain::channelmonitor:4226]   p:0355f8 ch:ae3367          Applying update, bringing update_id from 0 to 1 with 1 change(s).
node 0 TRACE [lightning::chain::channelmonitor:4289]   p:0355f8 ch:ae3367          Updating ChannelMonitor with latest counterparty commitment transaction info
node 0 DEBUG [lightning::chain::chainmonitor:1451]     p:0355f8 ch:ae3367          Persistence of ChannelMonitorUpdate id 1 completed

ldk-reviews-bot · 2025-11-11T12:52:31Z

👋 Thanks for assigning @valentinewallace as a reviewer!
I'll wait for their review and will help manage the review process.
Once they submit their review, I'll check if a second reviewer would be helpful.

TheBlueMatt · 2025-11-11T13:47:50Z

lightning/src/util/test_utils.rs

-		let s = format!("{:<55} {}", context, record.args);
+		let chan_id = record.channel_id.map(|id| format!("{}", id));
+		let chan_str = chan_id.as_deref().and_then(|s| s.get(..6)).unwrap_or("");
+		let s = format!("{:<55} {:<6} {}", context, chan_str, record.args);


Rather than just updating the test logger, let's instead maybe add a Display implementation for Record that includes all the relevant information? After we do that we'll need to update the one in fuzzing and IMO the docs on the logger to make clear that we intend to not include redundant information in the human-readable part of the log record (and that they absolutely need to include it if they want useful logs).

Display added and docs updated.

As a preparatory step for unifying test log output.

Makes sure that 4 and 5 character log levels line up.

Now that we have Display implemented on Record, the various test logger implementations can make use of that.

Previously, log messages often included the channel ID both in the message text and in the structured `channel_id` field. This led to redundant information and made it difficult to quickly identify which log lines pertain to a given channel, as the ID could appear in different positions or sometimes not at all. This change removes the channel ID from the message in all cases where it is already present in the structured field. A test run was used to verify that the structured field always appeared in these log calls. Some exceptions remain—for example, calls where the structured field contains a temporary channel ID and the message contains the final ID were left unchanged.

codecov · 2025-11-12T09:27:16Z

Codecov Report

❌ Patch coverage is 92.78846% with 15 lines in your changes missing coverage. Please review.
✅ Project coverage is 89.32%. Comparing base (cbbda61) to head (3506f92).
⚠️ Report is 19 commits behind head on main.

Files with missing lines	Patch %	Lines
lightning/src/util/logger.rs	79.54%	0 Missing and 9 partials ⚠️
lightning/src/ln/channel.rs	90.47%	3 Missing and 1 partial ⚠️
lightning/src/ln/htlc_reserve_unit_tests.rs	75.00%	2 Missing ⚠️

Additional details and impacted files

@@           Coverage Diff            @@
##             main    #4217    +/-   ##
========================================
  Coverage   89.31%   89.32%            
========================================
  Files         180      180            
  Lines      138055   138157   +102     
  Branches   138055   138157   +102     
========================================
+ Hits       123309   123412   +103     
+ Misses      12142    12130    -12     
- Partials     2604     2615    +11

Flag	Coverage Δ
fuzzing	`35.85% <53.88%> (+2.27%)`	⬆️
tests	`88.70% <92.78%> (-0.01%)`	⬇️

Flags with carried forward coverage won't be shown. Click here to find out more.

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.

🚀 New features to boost your workflow:

❄️ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.

TheBlueMatt · 2025-11-12T13:48:09Z

fuzz/src/onion_message.rs

 		&self, _sender: PublicKey, _peers: Vec<PublicKey>, destination: Destination,
 	) -> Result<OnionMessagePath, ()> {
-		Ok(OnionMessagePath { intermediate_nodes: vec![], destination, first_node_addresses: vec![] })
+		Ok(OnionMessagePath {


wtf rustfmt? This wasn't even changed 🤦

TheBlueMatt · 2025-11-12T13:56:11Z

lightning/src/util/logger.rs

+		let chan_id = self.channel_id.map(|id| format!("{}", id));
+		let chan_str = chan_id.as_deref().and_then(|s| s.get(..6)).unwrap_or("");
+		let context = format!("{:<5} [{}:{}]", self.level, self.module_path, self.line);
+		write!(f, "{:<48} {:<6} {}", context, chan_str, self.args)


Now that we're implementing this directly, let's avoid all the extra allocations here. Allocating on every log kinda blows for memory fragmentation, and while its a bit annoying, if we're gonna write the channel, the payment hash, and the peer, it'll add up fast. Also, presumably we should write the payment hash and peer?

Suggested change

let chan_id = self.channel_id.map(|id| format!("{}", id));

let chan_str = chan_id.as_deref().and_then(|s| s.get(..6)).unwrap_or("");

let context = format!("{:<5} [{}:{}]", self.level, self.module_path, self.line);

write!(f, "{:<48} {:<6} {}", context, chan_str, self.args)

use core::fmt::Write;

struct SubstringFormatter<'fmt: 'r, 'r>(usize, &'r mut fmt::Formatter<'fmt>);

impl<'fmt: 'r, 'r> Write for SubstringFormatter<'fmt, 'r> {

fn write_str(&mut self, s: &str) -> fmt::Result {

// Iterate over self.0 + 1 characters to find byte index of the end of the

// self.0'th unicode character, then write up to that point.

let mut char_count = 0;

let mut next_char_pos = 0;

for (pos, _) in s.char_indices().take(self.0 + 1) {

char_count += 1;

next_char_pos = pos;

}

let split_pos = if char_count == self.0 + 1 {

self.0 = 0;

next_char_pos

} else {

self.0 -= char_count;

s.len()

};

self.1.write_str(&s[..split_pos])

}

}

struct CountingFormatter<'fmt: 'r, 'r>(usize, &'r mut fmt::Formatter<'fmt>);

impl<'fmt: 'r, 'r> Write for &mut CountingFormatter<'fmt, 'r> {

fn write_str(&mut self, s: &str) -> fmt::Result {

self.0 += s.chars().count();

self.1.write_str(&s)

}

}

let mut count = CountingFormatter(0, f);

write!(&mut count, "{:<5} [{}:{}]", self.level, self.module_path, self.line)?;

let count = count.0;

let pad = core::str::from_utf8(&[b' '; 48]).unwrap();

if count < 48 {

f.write_str(&pad[..48 - count])?;

}

if let Some(counterparty) = self.peer_id {

write!(SubstringFormatter(11, f), "peer {}", counterparty)?;

} else {

write!(f, " ")?;

}

if let Some(channel_id) = self.channel_id {

write!(SubstringFormatter(12, f), " chan {}", channel_id)?;

} else {

write!(f, " ")?;

}

if let Some(payment_hash) = self.payment_hash {

write!(SubstringFormatter(11, f), " pmt {}", payment_hash)?;

} else {

write!(f, " ")?;

}

write!(f, " {}", self.args)

Yes, good one. I've changed the code a bit to only use one formatter that can also pad. Added comments. Also abbreviated the field names:

node 0 TRACE [lightning::ln::channel:12653] p:0355f8 ch:ae3367 h:544e62 Updating HTLC state for a newly-sent commitment_signed...```

Since most log messages no longer include the channel ID in their text, this commit updates the test logger to output the structured channel ID instead. The ID is truncated for readability. Similarly peer id and payment hash are logged. Co-authored-by: Matt Corallo <[email protected]>

TheBlueMatt

LGTM, needs rebase though.

TheBlueMatt · 2025-11-13T18:11:39Z

lightning/src/util/logger.rs

+		// Determine where to split the string. If we’ve found at least `self.0 + 1` characters, we’ve reached the
+		// cutoff point.
+		let split_pos = if char_count == self.0 + 1 {
+			// Reset remaining character counter to zero.


This kinda comment is pretty redundant with the code that just writes self.0 = 0 :)

joostjager force-pushed the chan-logging branch 2 times, most recently from 5bae991 to bf104c0 Compare November 11, 2025 13:11

joostjager marked this pull request as ready for review November 11, 2025 13:45

joostjager requested a review from valentinewallace November 11, 2025 13:45

TheBlueMatt reviewed Nov 11, 2025

View reviewed changes

joostjager force-pushed the chan-logging branch from bf104c0 to 9491fa7 Compare November 11, 2025 13:56

joostjager removed the request for review from valentinewallace November 11, 2025 14:00

joostjager added 3 commits November 12, 2025 08:45

Implement Display for Record

4629ee2

As a preparatory step for unifying test log output.

Align log levels

25b440e

Makes sure that 4 and 5 character log levels line up.

Unify test logger output

9ee6b26

Now that we have Display implemented on Record, the various test logger implementations can make use of that.

joostjager force-pushed the chan-logging branch from 9491fa7 to 98cffe3 Compare November 12, 2025 07:57

joostjager force-pushed the chan-logging branch 2 times, most recently from 44dec3f to 2f6b50a Compare November 12, 2025 08:13

joostjager requested a review from TheBlueMatt November 12, 2025 10:29

joostjager force-pushed the chan-logging branch from 2f6b50a to f2483eb Compare November 12, 2025 10:36

joostjager requested a review from valentinewallace November 12, 2025 16:22

TheBlueMatt reviewed Nov 12, 2025

View reviewed changes

joostjager force-pushed the chan-logging branch 3 times, most recently from a36e9fd to 61b1780 Compare November 13, 2025 10:26

joostjager force-pushed the chan-logging branch from 61b1780 to 3506f92 Compare November 13, 2025 10:29

joostjager added this to Weekly Goals Nov 13, 2025

joostjager self-assigned this Nov 13, 2025

TheBlueMatt reviewed Nov 13, 2025

View reviewed changes

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Uh oh!

Remove redundant channel ID logging #4217

Remove redundant channel ID logging #4217

joostjager commented Nov 11, 2025 •

edited

Loading

Uh oh!

ldk-reviews-bot commented Nov 11, 2025 •

edited

Loading

Uh oh!

TheBlueMatt Nov 11, 2025

Uh oh!

joostjager Nov 12, 2025

Uh oh!

codecov bot commented Nov 12, 2025 •

edited

Loading

Uh oh!

TheBlueMatt Nov 12, 2025

Uh oh!

joostjager Nov 13, 2025

Uh oh!

TheBlueMatt Nov 12, 2025

Uh oh!

joostjager Nov 13, 2025 •

edited

Loading

Uh oh!

TheBlueMatt left a comment

Uh oh!

TheBlueMatt Nov 13, 2025 •

edited

Loading

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

3 participants

-		let chan_id = self.channel_id.map(|id| format!("{}", id));
-		let chan_str = chan_id.as_deref().and_then(|s| s.get(..6)).unwrap_or("");
-		let context = format!("{:<5} [{}:{}]", self.level, self.module_path, self.line);
-		write!(f, "{:<48} {:<6} {}", context, chan_str, self.args)
+		use core::fmt::Write;
+		struct SubstringFormatter<'fmt: 'r, 'r>(usize, &'r mut fmt::Formatter<'fmt>);
+		impl<'fmt: 'r, 'r> Write for SubstringFormatter<'fmt, 'r> {
+			fn write_str(&mut self, s: &str) -> fmt::Result {
+				// Iterate over self.0 + 1 characters to find byte index of the end of the
+				// self.0'th unicode character, then write up to that point.
+				let mut char_count = 0;
+				let mut next_char_pos = 0;
+				for (pos, _) in s.char_indices().take(self.0 + 1) {
+					char_count += 1;
+					next_char_pos = pos;
+				}
+				let split_pos = if char_count == self.0 + 1 {
+					self.0 = 0;
+					next_char_pos
+				} else {
+					self.0 -= char_count;
+					s.len()
+				};
+				self.1.write_str(&s[..split_pos])
+			}
+		}
+		struct CountingFormatter<'fmt: 'r, 'r>(usize, &'r mut fmt::Formatter<'fmt>);
+		impl<'fmt: 'r, 'r> Write for &mut CountingFormatter<'fmt, 'r> {
+			fn write_str(&mut self, s: &str) -> fmt::Result {
+				self.0 += s.chars().count();
+				self.1.write_str(&s)
+			}
+		}
+		let mut count = CountingFormatter(0, f);
+		write!(&mut count, "{:<5} [{}:{}]", self.level, self.module_path, self.line)?;
+		let count = count.0;
+		let pad = core::str::from_utf8(&[b' '; 48]).unwrap();
+		if count < 48 {
+			f.write_str(&pad[..48 - count])?;
+		}
+		if let Some(counterparty) = self.peer_id {
+			write!(SubstringFormatter(11, f), "peer {}", counterparty)?;
+		} else {
+			write!(f, "           ")?;
+		}
+		if let Some(channel_id) = self.channel_id {
+			write!(SubstringFormatter(12, f), " chan {}", channel_id)?;
+		} else {
+			write!(f, "            ")?;
+		}
+		if let Some(payment_hash) = self.payment_hash {
+			write!(SubstringFormatter(11, f), " pmt {}", payment_hash)?;
+		} else {
+			write!(f, "           ")?;
+		}
+		write!(f, " {}", self.args)

Remove redundant channel ID logging #4217

Are you sure you want to change the base?

Remove redundant channel ID logging #4217

Conversation

joostjager commented Nov 11, 2025 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

ldk-reviews-bot commented Nov 11, 2025 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

TheBlueMatt Nov 11, 2025

Choose a reason for hiding this comment

Uh oh!

joostjager Nov 12, 2025

Choose a reason for hiding this comment

Uh oh!

codecov bot commented Nov 12, 2025 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Codecov Report

Uh oh!

TheBlueMatt Nov 12, 2025

Choose a reason for hiding this comment

Uh oh!

joostjager Nov 13, 2025

Choose a reason for hiding this comment

Uh oh!

TheBlueMatt Nov 12, 2025

Choose a reason for hiding this comment

Uh oh!

joostjager Nov 13, 2025 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

TheBlueMatt left a comment

Choose a reason for hiding this comment

Uh oh!

TheBlueMatt Nov 13, 2025 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

3 participants

joostjager commented Nov 11, 2025 •

edited

Loading

ldk-reviews-bot commented Nov 11, 2025 •

edited

Loading

codecov bot commented Nov 12, 2025 •

edited

Loading

joostjager Nov 13, 2025 •

edited

Loading

TheBlueMatt Nov 13, 2025 •

edited

Loading